Guard debug logs in pollPooledChannel - #2300
Conversation
SLF4J's Logger has overloads for one and two arguments only, so the four log statements in pollPooledChannel bind to debug(String, Object...) and build their varargs Object[3] at the call site regardless of whether debug is enabled. pollPooledChannel runs on every request, and its two pooled-channel branches are the steady-state keep-alive path, so this allocated an array per served request in production configurations that log at INFO or above. Wrap the calls in isDebugEnabled(), matching what sendRequestWithOpenChannel already does for its own three-argument statement a few lines up. Behaviour when debug logging is enabled is unchanged. Claude Code on behalf of Pavel Ptashyts Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
| // SLF4J has no three-argument overload, so every log statement in this method binds to | ||
| // debug(String, Object...) and allocates its varargs array at the call site whatever the | ||
| // level. This is the steady-state connection-reuse path, so guard them all explicitly. |
There was a problem hiding this comment.
This explains all four guards but it is buried in the deepest branch of the method. Can it move up above the override check, so it is visible from the path most requests actually take?
Also "every log statement in this method" is not quite right, the error call at the top binds to the Throwable overload and never allocates. Every debug statement would be accurate.
There was a problem hiding this comment.
Both fixed. The note sits at the top of the method now, right next to the values these statements log, so it is on the path whichever branch you follow.
And you are right about the wording: the onConnectionPoolAttempt failure binds to error(String, Throwable) and allocates nothing, so it is every debug statement, not every log statement. Reworded.
| final Channel channel = channelManager.poll(partitionKey); | ||
|
|
||
| if (channel != null) { | ||
| if (channel != null && LOGGER.isDebugEnabled()) { |
There was a problem hiding this comment.
This is the common path and there is nothing here saying why the guard exists. Moving the comment up would cover it.
There was a problem hiding this comment.
Same move covers this one. The note is above the override branch now, so it reads before either poll.
| // SLF4J has no three-argument overload, so every log statement in this method binds to | ||
| // debug(String, Object...) and allocates its varargs array at the call site whatever the | ||
| // level. This is the steady-state connection-reuse path, so guard them all explicitly. | ||
| if (LOGGER.isDebugEnabled()) { |
There was a problem hiding this comment.
Small correction to the description: the guard in sendRequestWithOpenChannel also hoists getNettyRequest().getHttpRequest() inside the branch, so it is not purely about the varargs array. The precedent stands, the reasoning is just a bit wider there.
There was a problem hiding this comment.
Corrected in the description. It hoists getNettyRequest().getHttpRequest() into the branch as well, so two calls are skipped on top of the array. The precedent still holds, the reasoning there is just wider than here.
Review feedback on AsyncHttpClient#2300. The note explaining why all four debug statements are guarded sat in the deepest branch of pollPooledChannel, where a reader following the path most requests take never passes it. Move it to the top of the method, next to the values the statements log. It also claimed "every log statement in this method", which is wrong: the onConnectionPoolAttempt failure at the top binds to error(String, Throwable) and allocates nothing. Say debug statement. Claude Code on behalf of Pavel Ptashyts Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
2 participants
Problem
NettyRequestSender.pollPooledChannelruns on every request. Four of itslog statements pass three arguments:
SLF4J's
Loggerdeclares overloads for one and two arguments only, so athree-argument call binds to
debug(String, Object...)and the compileremits the
Object[3]at the call site. The array is therefore allocatedbefore
debugis entered, whatever the configured level — the placeholdermechanism only defers formatting, not argument boxing.
Both pooled-channel branches are the steady-state keep-alive path, so a
client logging at INFO or above allocated one throwaway array per served
request.
Change
Wrap the four statements in
isDebugEnabled().sendRequestWithOpenChannela few lines up already guards its ownthree-argument statement, so the shape is not new to this file. Its guard
does a little more than avoid the array, though: it also hoists
future.getNettyRequest().getHttpRequest()inside the branch, so two methodcalls are skipped as well. The precedent stands, the reasoning there is just
wider than it is here.
Scope
Deliberately limited to
pollPooledChannel. The same pattern exists in afew colder places (
TimeoutTimerTask, the GOAWAY handler, the orphan-channelbranch in
AsyncHttpClientHandler); those are not per-request and are leftalone to keep this focused.
No public API change. No new tests: this is an allocation removal with no
observable behaviour change, and the existing suite covers both branches
(
ConnectionPoolTest,MaxTotalConnectionTest,ClientStatsTest).Verification
mvnw clean verify— BUILD SUCCESS, 1371 tests, 0 failures, 0 errors,19 skipped. Error Prone, NullAway and Revapi all clean.
Caveat on the testing gate:
AGENTS.mdrequires the build to run on JDK 11and no JDK 11 is installed on this machine, so it was run on JDK 17
(also in the CI matrix). The JDK 11 leg of CI on this PR is the real gate.
Claude Code on behalf of @pavel-ptashyts
🤖 Generated with Claude Code